CloudWatch LogsからKinesis Data Fireshoseサブスクリプションフィルターを使ってS3へログを転送した時のログ形式を、オリジナルのログ形式に戻す
いわさです。
仮想マシンのログファイルをCloudWatchエージェント等で、CloudWatch Logsへ転送するケース多いと思います。
その後、Kinesis Data Firehoseサブスクリプションフィルターを使うことでS3で長期的にログファイルの保存・アーカイブを行うことが出来ます。
しかし、CloudWatch Logs と Kinesis Data Firehoseの連携だけだとオリジナルのログデータにCloudWatch Logsに関する情報が追加されています。
この問題を解決し元のログデータに戻してS3へ格納するためには、Lambda関数が必要となります。
Lambda関数が必要らしいという情報まで辿り着いたところで、「Lambdaが必要...うっ頭が」という方もいらっしゃるかもしれません。
しかし、Lambdaにはブループリントが用意されており、前述のログ変換についても用意されています。
そしてコーディング不要でそのまま使い始めることが可能です。
変換なしのログ形式
Amazon Linux 2 の/var/messages
ログと、Windows Server 2019 の システムログ で試しています。
{ "messageType": "DATA_MESSAGE", "owner": "123456789012", "logGroup": "Windows/System", "logStream": "i-095dd791cbb79514d", "subscriptionFilters": [ "iwasa-cloudwatchlogs-WinSystemLogSubscriptionFilter-UEIJGPYHC0SE" ], "logEvents": [ { "id": "36277846857374658513237166582882787328672537367783538688", "timestamp": 1626754914888, "message": "<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T04:21:54.888493400Z'/><EventRecordID>68186</EventRecordID><Correlation/><Execution ProcessID='764' ThreadID='3524'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Windows Installer</Data><Data Name='param2'>stopped</Data><Binary>6D00730069007300650072007600650072002F0031000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Windows Installer service entered the stopped state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event>" } ] }{ "messageType": "DATA_MESSAGE", "owner": "123456789012", "logGroup": "Windows/System", "logStream": "i-095dd791cbb79514d", "subscriptionFilters": [ "iwasa-cloudwatchlogs-WinSystemLogSubscriptionFilter-UEIJGPYHC0SE" ], "logEvents": [ { "id": "36277847552221277409054322464316465099275899847217315840", "timestamp": 1626754946046, "message": "<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T04:22:26.046148800Z'/><EventRecordID>68187</EventRecordID><Correlation/><Execution ProcessID='764' ThreadID='3868'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>AppX Deployment Service (AppXSVC)</Data><Data Name='param2'>stopped</Data><Binary>41007000700058005300760063002F0031000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The AppX Deployment Service (AppXSVC) service entered the stopped state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event>" } ] }
Json形式で加工されます。
そして、logEvents
に生データが格納されています。
変換用のLambda関数 "Kinesis Data Firehose Cloudwatch Logs Processor" を使う
では冒頭で述べた、ブループリントを使ったLambda関数の作成を行ってみましょう。
Kinesis Data FirehoseでLambda関数変換を設定するデリバリーストリームのDetails
->Edit
を押下します。
そして、Transform source records with AWS Lambda
をEnabled
に設定し、Create new
ボタンで関数を作成します。
ブループリント選択画面が表示されます。
ここでKinesis Data Firehose Cloudwatch Logs Processor
を選択します。
選択すると、Lambda関数の作成画面に遷移します。
Lambda関数にロールを設定し、コードは変更しなくて良いです。
ただし、関数の設定からタイムアウトの時間だけ変更しましょう。デフォルトは3秒になっているのでKinesis Data Firehoseの画面で推奨されるように、1分以上に変更します。
なお、このLambda関数は Kinesis Data Firehose側から設定しなくとも、Lambdaからの関数新規作成時でも選択が可能です。
Kinesisに戻って関数を設定したら完了です。
変換によって扱いやすいログ形式に。Athenaでもクエリしやすい
では、変換されS3へ転送されたログを確認してみましょう。
<Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:27.903276900Z'/><EventRecordID>68821</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='752'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Remote Registry</Data><Data Name='param2'>stopped</Data><Binary>520065006D006F0074006500520065006700690073007400720079002F0031000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Remote Registry service entered the stopped state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:31.696446500Z'/><EventRecordID>68822</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='1704'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Windows Update</Data><Data Name='param2'>running</Data><Binary>770075006100750073006500720076002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Windows Update service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:36.244351400Z'/><EventRecordID>68823</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='752'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Delivery Optimization</Data><Data Name='param2'>running</Data><Binary>44006F005300760063002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Delivery Optimization service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:36.356442400Z'/><EventRecordID>68824</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='1916'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Storage Service</Data><Data Name='param2'>running</Data><Binary>530074006F0072005300760063002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Storage Service service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:36.595342700Z'/><EventRecordID>68825</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='752'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>State Repository Service</Data><Data Name='param2'>running</Data><Binary>530074006100740065005200650070006F007300690074006F00720079002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The State Repository Service service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:36.676303900Z'/><EventRecordID>68826</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='752'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>AppX Deployment Service (AppXSVC)</Data><Data Name='param2'>running</Data><Binary>41007000700058005300760063002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The AppX Deployment Service (AppXSVC) service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Service Control Manager' Guid='{555908d1-a6d7-4695-8e1e-26931d2012f4}' EventSourceName='Service Control Manager'/><EventID Qualifiers='16384'>7036</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8080000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:38:36.709681600Z'/><EventRecordID>68827</EventRecordID><Correlation/><Execution ProcessID='736' ThreadID='1916'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security/></System><EventData><Data Name='param1'>Client License Service (ClipSVC)</Data><Data Name='param2'>running</Data><Binary>43006C00690070005300560043002F0034000000</Binary></EventData><RenderingInfo Culture='en-US'><Message>The Client License Service (ClipSVC) service entered the running state.</Message><Level>Information</Level><Task></Task><Opcode></Opcode><Channel></Channel><Provider>Microsoft-Windows-Service Control Manager</Provider><Keywords><Keyword>Classic</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Microsoft-Windows-WindowsUpdateClient' Guid='{945a8954-c147-4acd-923f-40c45405a658}'/><EventID>44</EventID><Version>1</Version><Level>4</Level><Task>1</Task><Opcode>12</Opcode><Keywords>0x8000000000002004</Keywords><TimeCreated SystemTime='2021-07-20T11:38:39.888076300Z'/><EventRecordID>68828</EventRecordID><Correlation ActivityID='{5763a5f8-7d5a-0000-46ab-63575a7dd701}'/><Execution ProcessID='1244' ThreadID='2360'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security UserID='S-1-5-18'/></System><EventData><Data Name='updateTitle'>Security Intelligence Update for Microsoft Defender Antivirus - KB2267602 (Version 1.343.1338.0)</Data><Data Name='updateGuid'>{7be15a28-ba35-417c-a4eb-043abc05d9dd}</Data><Data Name='updateRevisionNumber'>200</Data></EventData><RenderingInfo Culture='en-US'><Message>Windows Update started downloading an update.</Message><Level>Information</Level><Task>Windows Update Agent</Task><Opcode>Download</Opcode><Channel>System</Channel><Provider>Microsoft-Windows-WindowsUpdateClient</Provider><Keywords><Keyword>Download</Keyword><Keyword>Started</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Microsoft-Windows-WindowsUpdateClient' Guid='{945a8954-c147-4acd-923f-40c45405a658}'/><EventID>43</EventID><Version>1</Version><Level>4</Level><Task>1</Task><Opcode>13</Opcode><Keywords>0x8000000000002008</Keywords><TimeCreated SystemTime='2021-07-20T11:38:39.888079300Z'/><EventRecordID>68829</EventRecordID><Correlation ActivityID='{5763a5f8-7d5a-0000-46ab-63575a7dd701}'/><Execution ProcessID='1244' ThreadID='2360'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security UserID='S-1-5-18'/></System><EventData><Data Name='updateTitle'>Security Intelligence Update for Microsoft Defender Antivirus - KB2267602 (Version 1.343.1338.0)</Data><Data Name='updateGuid'>{7be15a28-ba35-417c-a4eb-043abc05d9dd}</Data><Data Name='updateRevisionNumber'>200</Data></EventData><RenderingInfo Culture='en-US'><Message>Installation Started: Windows has started installing the following update: Security Intelligence Update for Microsoft Defender Antivirus - KB2267602 (Version 1.343.1338.0)</Message><Level>Information</Level><Task>Windows Update Agent</Task><Opcode>Installation</Opcode><Channel>System</Channel><Provider>Microsoft-Windows-WindowsUpdateClient</Provider><Keywords><Keyword>Installation</Keyword><Keyword>Started</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Microsoft-Windows-WindowsUpdateClient' Guid='{945a8954-c147-4acd-923f-40c45405a658}'/><EventID>19</EventID><Version>1</Version><Level>4</Level><Task>1</Task><Opcode>13</Opcode><Keywords>0x8000000000000018</Keywords><TimeCreated SystemTime='2021-07-20T11:38:58.584445900Z'/><EventRecordID>68830</EventRecordID><Correlation ActivityID='{5763a5f8-7d5a-0000-46ab-63575a7dd701}'/><Execution ProcessID='1244' ThreadID='2360'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security UserID='S-1-5-18'/></System><EventData><Data Name='updateTitle'>Security Intelligence Update for Microsoft Defender Antivirus - KB2267602 (Version 1.343.1338.0)</Data><Data Name='updateGuid'>{7be15a28-ba35-417c-a4eb-043abc05d9dd}</Data><Data Name='updateRevisionNumber'>200</Data><Data Name='serviceGuid'>{9482f4b4-e343-43b6-b170-9a65bc822c77}</Data></EventData><RenderingInfo Culture='en-US'><Message>Installation Successful: Windows successfully installed the following update: Security Intelligence Update for Microsoft Defender Antivirus - KB2267602 (Version 1.343.1338.0)</Message><Level>Information</Level><Task>Windows Update Agent</Task><Opcode>Installation</Opcode><Channel>System</Channel><Provider>Microsoft-Windows-WindowsUpdateClient</Provider><Keywords><Keyword>Installation</Keyword><Keyword>Success</Keyword></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Microsoft-Windows-Time-Service' Guid='{06edcfeb-0fd0-4e53-acca-a6f8bbf81bcb}'/><EventID>37</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8000000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:40:00.027722700Z'/><EventRecordID>68831</EventRecordID><Correlation/><Execution ProcessID='1368' ThreadID='1736'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security UserID='S-1-5-19'/></System><EventData Name='TMP_EVENT_TIME_SOURCE_REACHABLE'><Data Name='TimeSource'>169.254.169.123,0x9 (ntp.m|0x9|0.0.0.0:123->169.254.169.123:123)</Data></EventData><RenderingInfo Culture='en-US'><Message>The time provider NtpClient is currently receiving valid time data from 169.254.169.123,0x9 (ntp.m|0x9|0.0.0.0:123->169.254.169.123:123).</Message><Level>Information</Level><Task></Task><Opcode>Info</Opcode><Channel>System</Channel><Provider>Microsoft-Windows-Time-Service</Provider><Keywords></Keywords></RenderingInfo></Event> <Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event'><System><Provider Name='Microsoft-Windows-Time-Service' Guid='{06edcfeb-0fd0-4e53-acca-a6f8bbf81bcb}'/><EventID>35</EventID><Version>0</Version><Level>4</Level><Task>0</Task><Opcode>0</Opcode><Keywords>0x8000000000000000</Keywords><TimeCreated SystemTime='2021-07-20T11:40:00.043083600Z'/><EventRecordID>68832</EventRecordID><Correlation/><Execution ProcessID='1368' ThreadID='1736'/><Channel>System</Channel><Computer>EC2AMAZ-P1T7GOG</Computer><Security UserID='S-1-5-19'/></System><EventData Name='TMP_EVENT_TIME_SOURCE_CHOSEN'><Data Name='TimeSource'>169.254.169.123,0x9 (ntp.m|0x9|0.0.0.0:123->169.254.169.123:123)</Data><Data Name='TimeSourceRefId'>2074738345</Data><Data Name='CurrentStratumNumber'>4</Data></EventData><RenderingInfo Culture='en-US'><Message>The time service is now synchronizing the system time with the time source 169.254.169.123,0x9 (ntp.m|0x9|0.0.0.0:123->169.254.169.123:123) with reference id 2074738345. Current local stratum number is 4.</Message><Level>Information</Level><Task></Task><Opcode>Info</Opcode><Channel>System</Channel><Provider>Microsoft-Windows-Time-Service</Provider><Keywords></Keywords></RenderingInfo></Event>
良いですね。
生ログに近いデータが格納されているのではないでしょうか。
まとめ
関数については、データタイプを判定のうえlogEvents
を抽出し、改行コードを付与した変換を行う処理となっています。
ブループリントを使うことでこういった処理が実装不要で利用可能です。
生ログを格納することで、Athena等でも使いやすくなるケースがあると思いますので、是非試してみてください。